[INFO] cloning repository https://github.com/danjl1100/kopia-exporter
[INFO] running `Command { std: "git" "-c" "credential.helper=" "-c" "credential.helper=/workspace/cargo-home/bin/git-credential-null" "clone" "--bare" "https://github.com/danjl1100/kopia-exporter" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fdanjl1100%2Fkopia-exporter", kill_on_drop: false }`
[INFO] [stderr] Cloning into bare repository '/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fdanjl1100%2Fkopia-exporter'...
[INFO] running `Command { std: "git" "rev-parse" "HEAD", kill_on_drop: false }`
[INFO] [stdout] 4a38e1b7a1d762ce52b0789b0e0380704712b1a9
[INFO] testing danjl1100/kopia-exporter against try#0abe69e6c16114311cc2700e972492e64d69c28f for pr-154065
[INFO] running `Command { std: "git" "clone" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fdanjl1100%2Fkopia-exporter" "/workspace/builds/worker-1-tc2/source", kill_on_drop: false }`
[INFO] [stderr] Cloning into '/workspace/builds/worker-1-tc2/source'...
[INFO] [stderr] done.
[INFO] started tweaking git repo https://github.com/danjl1100/kopia-exporter
[INFO] finished tweaking git repo https://github.com/danjl1100/kopia-exporter
[INFO] tweaked toml for git repo https://github.com/danjl1100/kopia-exporter written to /workspace/builds/worker-1-tc2/source/Cargo.toml
[INFO] validating manifest of git repo https://github.com/danjl1100/kopia-exporter on toolchain 0abe69e6c16114311cc2700e972492e64d69c28f
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate git repo https://github.com/danjl1100/kopia-exporter already has a lockfile, it will not be regenerated
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 9d332b3939d128f3d4e457e0afc55cb1adb87b20ce70089576fa717d2125fdf0
[INFO] running `Command { std: "docker" "start" "-a" "9d332b3939d128f3d4e457e0afc55cb1adb87b20ce70089576fa717d2125fdf0", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "9d332b3939d128f3d4e457e0afc55cb1adb87b20ce70089576fa717d2125fdf0", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "9d332b3939d128f3d4e457e0afc55cb1adb87b20ce70089576fa717d2125fdf0", kill_on_drop: false }`
[INFO] [stdout] 9d332b3939d128f3d4e457e0afc55cb1adb87b20ce70089576fa717d2125fdf0
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 403a3efc041ee3cccd9ace90163e21887553bb4b7315c83bde810a01e60e8d91
[INFO] running `Command { std: "docker" "start" "-a" "403a3efc041ee3cccd9ace90163e21887553bb4b7315c83bde810a01e60e8d91", kill_on_drop: false }`
[INFO] [stderr]    Compiling serde v1.0.219
[INFO] [stderr]    Compiling anstyle-query v1.1.4
[INFO] [stderr]    Compiling eyre v0.6.12
[INFO] [stderr]    Compiling serde_json v1.0.143
[INFO] [stderr]    Compiling proc-macro2 v1.0.101
[INFO] [stderr]    Compiling chunked_transfer v1.5.0
[INFO] [stderr]    Compiling indenter v0.3.4
[INFO] [stderr]    Compiling ascii v1.1.0
[INFO] [stderr]    Compiling jiff v0.2.15
[INFO] [stderr]    Compiling anstream v0.6.20
[INFO] [stderr]    Compiling clap_builder v4.5.44
[INFO] [stderr]    Compiling tiny_http v0.12.0
[INFO] [stderr]    Compiling quote v1.0.40
[INFO] [stderr]    Compiling syn v2.0.106
[INFO] [stderr]    Compiling serde_derive v1.0.219
[INFO] [stderr]    Compiling clap_derive v4.5.45
[INFO] [stderr]    Compiling clap v4.5.45
[INFO] [stderr]    Compiling kopia-exporter v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 20.49s
[INFO] running `Command { std: "docker" "inspect" "403a3efc041ee3cccd9ace90163e21887553bb4b7315c83bde810a01e60e8d91", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "403a3efc041ee3cccd9ace90163e21887553bb4b7315c83bde810a01e60e8d91", kill_on_drop: false }`
[INFO] [stdout] 403a3efc041ee3cccd9ace90163e21887553bb4b7315c83bde810a01e60e8d91
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] af9c8e99aec044e91dd78fc7fd49b2ec7de98055c3eb75e952b541443a9857f2
[INFO] running `Command { std: "docker" "start" "-a" "af9c8e99aec044e91dd78fc7fd49b2ec7de98055c3eb75e952b541443a9857f2", kill_on_drop: false }`
[INFO] [stderr]    Compiling libc v0.2.175
[INFO] [stderr]    Compiling rustix v1.0.8
[INFO] [stderr]    Compiling linux-raw-sys v0.9.4
[INFO] [stderr]    Compiling bitflags v2.9.3
[INFO] [stderr]    Compiling minreq v2.14.0
[INFO] [stderr]    Compiling insta v1.43.1
[INFO] [stderr]    Compiling getrandom v0.3.3
[INFO] [stderr]    Compiling tempfile v3.21.0
[INFO] [stderr]    Compiling kopia-exporter v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 7.90s
[INFO] running `Command { std: "docker" "inspect" "af9c8e99aec044e91dd78fc7fd49b2ec7de98055c3eb75e952b541443a9857f2", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "af9c8e99aec044e91dd78fc7fd49b2ec7de98055c3eb75e952b541443a9857f2", kill_on_drop: false }`
[INFO] [stdout] af9c8e99aec044e91dd78fc7fd49b2ec7de98055c3eb75e952b541443a9857f2
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] 94fb263c3a97dad96f57d3e58086486cb67cfbb33f2bdd34079ff2fcd305760b
[INFO] running `Command { std: "docker" "start" "-a" "94fb263c3a97dad96f57d3e58086486cb67cfbb33f2bdd34079ff2fcd305760b", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.24s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/kopia_exporter-468ec7ea821bfb47)
[INFO] [stdout] 
[INFO] [stdout] running 48 tests
[INFO] [stdout] test kopia::tests::parse_single_snapshot ... ok
[INFO] [stdout] test kopia::tests::retention_counts ... ok
[INFO] [stdout] test metrics::kopia_snapshot_age_seconds::tests::snapshot_age_metrics_empty ... ok
[INFO] [stdout] test kopia::tests::parse_sample_data ... ok
[INFO] [stdout] test kopia::tests::retention_counts_with_multiple_slots ... ok
[INFO] [stdout] test metrics::kopia_snapshot_age_seconds::tests::snapshot_age_metric_invalid_time ... ok
[INFO] [stdout] test metrics::kopia_snapshot_age_seconds::tests::snapshot_age_multi_source ... ok
[INFO] [stdout] test metrics::kopia_snapshot_errors_ignored_total::tests::latest_snapshot_ignored_errors_metrics_empty ... ok
[INFO] [stdout] test metrics::kopia_snapshot_errors_ignored_total::tests::latest_snapshot_ignored_errors_metrics ... ok
[INFO] [stdout] test metrics::kopia_snapshot_errors_total::tests::snapshot_errors_metrics_empty ... ok
[INFO] [stdout] test metrics::kopia_snapshot_errors_total::tests::snapshot_errors_multi_source ... ok
[INFO] [stdout] test metrics::kopia_snapshot_age_seconds::tests::snapshot_age_metrics ... ok
[INFO] [stdout] test metrics::kopia_snapshot_failed_files_total::tests::snapshot_failed_files_metrics ... ok
[INFO] [stdout] test metrics::kopia_snapshot_errors_total::tests::snapshot_errors_no_errors ... ok
[INFO] [stdout] test metrics::kopia_snapshot_failed_files_total::tests::snapshot_failed_files_metrics_empty ... ok
[INFO] [stdout] test metrics::kopia_snapshot_failed_files_total::tests::snapshot_failed_files_metrics_no_failures ... ok
[INFO] [stdout] test metrics::kopia_snapshot_errors_ignored_total::tests::latest_snapshot_ignored_errors_multi_source ... ok
[INFO] [stdout] test metrics::kopia_snapshot_errors_total::tests::snapshot_errors ... ok
[INFO] [stdout] test metrics::kopia_snapshot_failed_files_total::tests::snapshot_failed_files_multi_source ... ok
[INFO] [stdout] test metrics::kopia_snapshot_last_success_timestamp::tests::snapshot_last_success_timestamp_invalid_time ... ok
[INFO] [stdout] test metrics::kopia_snapshot_last_success_timestamp::tests::snapshot_last_success_timestamp_metrics ... ok
[INFO] [stdout] test metrics::kopia_snapshot_last_success_timestamp::tests::snapshot_last_success_timestamp_metrics_empty ... ok
[INFO] [stdout] test metrics::kopia_snapshot_last_success_timestamp::tests::snapshot_last_success_timestamp_multi_source ... ok
[INFO] [stdout] test metrics::kopia_snapshot_oldest_age_seconds::tests::snapshot_oldest_age_metric_invalid_time ... ok
[INFO] [stdout] test metrics::kopia_snapshot_oldest_age_seconds::tests::snapshot_oldest_age_metrics_empty ... ok
[INFO] [stdout] test metrics::kopia_snapshot_oldest_age_seconds::tests::snapshot_oldest_age_metrics ... ok
[INFO] [stdout] test metrics::kopia_snapshot_parse_errors_source::tests::source_parse_errors_invalid_user ... ok
[INFO] [stdout] test metrics::kopia_snapshot_parse_errors_source::tests::source_parse_errors_multiple_different_values ... ok
[INFO] [stdout] test metrics::kopia_snapshot_parse_errors_timestamp_total::tests::snapshot_parse_errors_timestamp_multi_source ... ok
[INFO] [stdout] test metrics::kopia_snapshot_oldest_age_seconds::tests::snapshot_oldest_age_multi_source ... ok
[INFO] [stdout] test metrics::kopia_snapshots_by_retention::tests::snapshots_by_retention_multi_source ... ok
[INFO] [stdout] test metrics::kopia_snapshot_size_bytes_total::tests::latest_snapshot_size_multi_source ... ok
[INFO] [stdout] test metrics::kopia_snapshot_size_bytes_change::tests::snapshot_size_change_multi_source ... ok
[INFO] [stdout] test metrics::kopia_snapshot_size_bytes_change::tests::snapshot_size_change_negative ... ok
[INFO] [stdout] test metrics::kopia_snapshot_size_bytes_total::tests::latest_snapshot_size_metrics ... ok
[INFO] [stdout] test metrics::kopia_snapshot_size_bytes_total::tests::latest_snapshot_size_metrics_empty ... ok
[INFO] [stdout] test metrics::kopia_snapshot_size_bytes_change::tests::snapshot_size_change_single_snapshot ... ok
[INFO] [stdout] test metrics::kopia_snapshots_total::tests::snapshots_total_multi_source ... ok
[INFO] [stdout] test metrics::kopia_snapshots_total::tests::snapshots_total_metrics ... ok
[INFO] [stdout] test metrics::tests::generate_all_metrics ... ok
[INFO] [stdout] test metrics::kopia_snapshot_size_bytes_change::tests::snapshot_size_change_positive ... ok
[INFO] [stdout] test metrics::kopia_snapshots_by_retention::tests::snapshots_by_retention_metrics ... ok
[INFO] [stdout] test metrics::kopia_snapshots_total::tests::snapshots_total_metrics_single ... ok
[INFO] [stdout] test metrics::kopia_snapshot_parse_errors_source::tests::source_parse_errors_invalid_host ... ok
[INFO] [stdout] test metrics::kopia_snapshot_size_bytes_change::tests::snapshot_size_change_empty ... ok
[INFO] [stdout] test metrics::kopia_snapshot_parse_errors_source::tests::source_parse_errors_none ... ok
[INFO] [stdout] test metrics::kopia_snapshots_total::tests::snapshots_total_metrics_empty ... ok
[INFO] [stdout] test metrics::tests::full_snapshot ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 48 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.04s
[INFO] [stdout] 
[INFO] [stderr]      Running unittests src/bin/fake-kopia.rs (/opt/rustwide/target/debug/deps/fake_kopia-083262e3e18144ef)
[INFO] [stdout] 
[INFO] [stdout] running 0 tests
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running unittests src/main.rs (/opt/rustwide/target/debug/deps/kopia_exporter-fe378f251413b393)
[INFO] [stdout] 
[INFO] [stdout] running 4 tests
[INFO] [stdout] test tests::delay_calculation_and_cap ... ok
[INFO] [stdout] test tests::start_server_with_retry_success_first_attempt ... ok
[INFO] [stdout] test tests::start_server_with_retry_no_retries ... ok
[INFO] [stdout] test tests::start_server_with_retry_exhausted ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 4 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 3.01s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/entrypoint.rs (/opt/rustwide/target/debug/deps/entrypoint-2114e154ebedbbff)
[INFO] [stdout] 
[INFO] [stdout] running 12 tests
[INFO] [stdout] test common::bind_retry_test::test_bind_retry_with_occupied_port ... ok
[INFO] [stdout] test common::bind_retry_test::test_cli_bind_retry_flag ... ok
[INFO] [stdout] test common::integration_test::test_subprocess_with_fake_kopia ... ok
[INFO] [stdout] test common::integration_test::test_kopia_timeout_returns_500 ... FAILED
[INFO] [stdout] test common::integration_test::test_web_server_integration ... ok
[INFO] [stdout] test common::integration_test::test_basic_auth_integration ... ok
[INFO] [stdout] test common::integration_test::test_basic_auth_credentials_file_integration ... ok
[INFO] [stdout] test common::integration_test::test_timeout_prints_stdout_and_stderr ... ok
[INFO] [stdout] test common::integration_test::test_kopia_timeout_forever_returns_500 ... ok
[INFO] [stdout] test common::integration_test::test_caching_reduces_subprocess_calls ... ok
[INFO] [stdout] test common::integration_test::test_large_json_output_success ... ok
[INFO] [stderr] error: test failed, to rerun pass `--test entrypoint`
[INFO] [stdout] test common::bind_retry_test::test_bind_retry_success_after_port_freed ... ok
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout] 
[INFO] [stdout] ---- common::integration_test::test_kopia_timeout_returns_500 stdout ----
[INFO] [stdout] Error: Connection refused (os error 111)
[INFO] [stdout] 
[INFO] [stdout] Caused by:
[INFO] [stdout]     Connection refused (os error 111)
[INFO] [stdout] 
[INFO] [stdout] Location:
[INFO] [stdout]     tests/test_helpers/mod.rs:107:12
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout]     common::integration_test::test_kopia_timeout_returns_500
[INFO] [stdout] 
[INFO] [stdout] test result: FAILED. 11 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 3.53s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "94fb263c3a97dad96f57d3e58086486cb67cfbb33f2bdd34079ff2fcd305760b", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "94fb263c3a97dad96f57d3e58086486cb67cfbb33f2bdd34079ff2fcd305760b", kill_on_drop: false }`
[INFO] [stdout] 94fb263c3a97dad96f57d3e58086486cb67cfbb33f2bdd34079ff2fcd305760b
